
import os
import psutil
import subprocess
from glob import glob

import jwst
from jwst.pipeline.calwebb_detector1 import Detector1Pipeline
from jwst.assign_wcs.assign_wcs_step import AssignWcsStep
from jwst.msaflagopen.msaflagopen_step import MSAFlagOpenStep
from jwst.extract_2d.extract_2d_step import Extract2dStep
from jwst.srctype.srctype_step import SourceTypeStep
from jwst.flatfield.flat_field_step import FlatFieldStep
from jwst.pathloss.pathloss_step import PathLossStep
from jwst.barshadow import BarShadowStep
from jwst import datamodels

# The latest version of NPTT is installed in the requirements text file at:
# /jwst_validation_notebooks/environment.yml

# import NPTT
import nirspec_pipe_testing_tool as nptt

# To get data from Artifactory
from ci_watson.artifactory_helpers import get_bigdata


# Create a temporary directory to hold notebook output, and change the working directory to that directory.
from tempfile import TemporaryDirectory
import shutil
data_dir = TemporaryDirectory()

# If you have files that are in the notebook's directory, but that the notebook will need to use while
# running, copy them into the temporary directory here.
#
# files = ['name_of_file']
# for file_name in files:
#     shutil.copy(file_name, os.path.join(data_dir.name, file_name))

os.chdir(data_dir.name)


# Make sure that the version used is the right one

pipeline_version = jwst.__version__
nptt_version = nptt.__version__

print("Using jwst pipeline version: ", pipeline_version)
print("Using NPTT version: ", nptt_version)

Using jwst pipeline version:  1.1.0
Using NPTT version:  1.1.11


testing_data = {              
                'mos_prism_clear':{
                                  'uncal_file_nrs1': 'mos_prism_nrs1_uncal.fits',
                                  'uncal_file_nrs2': 'mos_prism_nrs2_uncal.fits',
                                  'msa_shutter_config': 'V0030006000104_msa.fits' },
                
                'mos_g140m_f100lp':{
                                  'uncal_file_nrs1': 'mos_g140m_line1_NRS1_uncal.fits',
                                  'uncal_file_nrs2': 'mos_g140m_line1_NRS2_uncal.fits',  
                                  'msa_shutter_config': 'V8460001000101_msa.fits' }
                }


# define function to pull data from Artifactory
def get_artifactory_file(data_set_dict, detector):
    """This function creates a list with all the files needed per detector to run the test.
    Args:
        data_set_dict: dictionary, contains inputs for a specific mode and configuration
        detector: string, either nrs1 or nrs2
    Returns:
        data: list, contains all files needed to run test
    """
    files2obtain = ['uncal_file_nrs1', 'msa_shutter_config']
    data = []
    for file in files2obtain:
        data_file = None
        try: 
            if '_nrs' in file and '2' in detector:
                file = file.replace('_nrs1', '_nrs2')

            data_file = get_bigdata('jwst_validation_notebooks',
                                         'validation_data',
                                         'nirspec_data', 
                                         data_set_dict[file])
        except TypeError:
            data.append(None)
            continue

        data.append(data_file)

    return data


# Set common NPTT switches for this test

# accepted threshold difference with respect to benchmark files
barshadow_threshold_diff = 0.0025

# other variables
mode_used = 'MOS'
write_barshadow_files = False
show_final_fig = True
save_final_fig = False
show_intermediary_figs = False
save_intermediary_figs = False

# Get the data
results_dict = {}
detectors = ['nrs1', 'nrs2']
for mode_config, data_set_dict in testing_data.items():
    for det in detectors:
        print('Testing files for detector: ', det)
        data = get_artifactory_file(data_set_dict, det)
        uncal_file, msa_shutter_config = data
        print('Working with uncal_file: ', uncal_file)
        uncal_basename = os.path.basename(uncal_file)
        
        # Make sure there is a local copy of the MSA shutter configuration file
        if msa_shutter_config is not None:
            subprocess.run(['cp', msa_shutter_config , '.'])
        
        # Run the stage 1 pipeline 
        rate_object = Detector1Pipeline.call(uncal_file)
        # Make sure the MSA shutter configuration file is set up correctly
        if msa_shutter_config is not None:
            msa_metadata = rate_object.meta.instrument.msa_metadata_file
            if msa_metadata is None or msa_metadata == 'N/A':
                rate_object.meta.instrument.msa_metadata_file = msa_shutter_config

        # Run the stage 2 pipeline steps
        try:
            pipe_object = AssignWcsStep.call(rate_object)
        except:
            print('No open slits fall on detector ', det, '\n')
            continue
        pipe_object = MSAFlagOpenStep.call(pipe_object)
        pipe_object = Extract2dStep.call(pipe_object)
        pipe_object = SourceTypeStep.call(pipe_object)
        pipe_object = FlatFieldStep.call(pipe_object, save_interpolated_flat=False)
        pathloss_object = PathLossStep.call(pipe_object)
        barshadow_object = BarShadowStep.call(pathloss_object)

        # Run the validation test
        %matplotlib inline
        
        _, result_msg, _ = nptt.calwebb_spec2_pytests.auxiliary_code.barshadow_testing.run_barshadow_tests(
                                                            pathloss_object, 
                                                            barshadow_object,
                                                            barshadow_threshold_diff=barshadow_threshold_diff,
                                                            save_final_figs=save_final_fig,
                                                            show_final_figs=show_final_fig,
                                                            save_intermediary_figs=save_intermediary_figs,
                                                            show_intermediary_figs=show_intermediary_figs,
                                                            write_barshadow_files=write_barshadow_files)

        # Remove fits files from the repo directory
        local_fits_files = glob('./*.fits')
        for fits_file in local_fits_files:
            try:
                subprocess.run(['rm', fits_file])
            except FileNotFound:
                print('Fits file does not exist in current working directory: ', fits_file)

        # Did the test passed 
        print("Did barshadow validation test passed? ", result_msg, "\n\n")
        rd = {mode_config: result_msg}
        results_dict.update(rd)
        
        # close all open files
        psutil.Process().open_files()
        closing_files = []
        for fd in psutil.Process().open_files():
            if data_dir.name in fd.path:
                closing_files.append(fd)
        for fd in closing_files:
            open(fd.fd).close()

Testing files for detector:  nrs1
Working with uncal_file:  /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_prism_nrs1_uncal.fits

2021-03-13 00:09:16,952 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2021-03-13 00:09:16,954 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2021-03-13 00:09:16,955 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2021-03-13 00:09:16,957 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2021-03-13 00:09:16,958 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2021-03-13 00:09:16,959 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2021-03-13 00:09:16,960 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2021-03-13 00:09:16,961 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2021-03-13 00:09:16,962 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2021-03-13 00:09:16,963 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2021-03-13 00:09:16,964 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2021-03-13 00:09:16,965 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2021-03-13 00:09:16,966 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2021-03-13 00:09:16,967 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2021-03-13 00:09:16,969 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2021-03-13 00:09:16,970 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2021-03-13 00:09:16,971 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2021-03-13 00:09:17,051 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_prism_nrs1_uncal.fits',).
2021-03-13 00:09:17,060 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2021-03-13 00:09:17,171 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_prism_nrs1_uncal.fits' reftypes = ['dark', 'gain', 'ipc', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2021-03-13 00:09:17,180 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0086.fits'.
2021-03-13 00:09:17,181 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits'.
2021-03-13 00:09:17,182 - stpipe.Detector1Pipeline - INFO - Prefetch for IPC reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_ipc_0011.fits'.
2021-03-13 00:09:17,183 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0018.fits'.
2021-03-13 00:09:17,185 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0010.fits'.
2021-03-13 00:09:17,186 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2021-03-13 00:09:17,186 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0018.fits'.
2021-03-13 00:09:17,187 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_refpix_0022.fits'.
2021-03-13 00:09:17,188 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2021-03-13 00:09:17,189 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2021-03-13 00:09:17,189 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0020.fits'.
2021-03-13 00:09:17,190 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0113.fits'.
2021-03-13 00:09:17,191 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2021-03-13 00:09:17,192 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2021-03-13 00:09:17,192 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2021-03-13 00:09:17,497 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:17,498 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:17,681 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2021-03-13 00:09:17,682 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2021-03-13 00:09:17,683 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2021-03-13 00:09:17,751 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:17,752 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:17,768 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0010.fits
2021-03-13 00:09:18,160 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2021-03-13 00:09:18,261 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:18,263 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:18,278 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0020.fits
2021-03-13 00:09:19,044 - stpipe.Detector1Pipeline.saturation - INFO - Detected 9869 saturated pixels
2021-03-13 00:09:19,086 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2021-03-13 00:09:19,115 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2021-03-13 00:09:19,218 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:19,220 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:19,235 - stpipe.Detector1Pipeline.ipc - INFO - Using IPC reference file /grp/crds/cache/references/jwst/jwst_nirspec_ipc_0011.fits
2021-03-13 00:09:19,726 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2021-03-13 00:09:19,821 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:19,822 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:19,838 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0113.fits
2021-03-13 00:09:19,912 - stpipe.Detector1Pipeline.superbias - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/stdatamodels/validate.py:34: ValidationWarning: While validating meta.exposure.readpatt the following error occurred:
'ALLIRS2' is not one of ['ACQ1', 'ACQ2', 'BRIGHT1', 'BRIGHT2', 'DEEP2', 'DEEP8', 'FAST', 'FASTGRPAVG', 'FASTGRPAVG8', 'FASTGRPAVG16', 'FASTGRPAVG32', 'FASTGRPAVG64', 'FASTR1', 'FASTR100', 'FGS', 'FGS60', 'FGS8370', 'FGS840', 'FGSRAPID', 'FINEGUIDE', 'ID', 'MEDIUM2', 'MEDIUM8', 'NIS', 'NISRAPID', 'NRS', 'NRSIRS2', 'NRSN16R4', 'NRSN32R8', 'NRSN8R2', 'NRSRAPID', 'NRSIRS2RAPID', 'NRSRAPIDD1', 'NRSRAPIDD2', 'NRSRAPIDD6', 'NRSSLOW', 'RAPID', 'SHALLOW2', 'SHALLOW4', 'SLOW', 'SLOWR1', 'TRACK', 'ANY', 'N/A']

Failed validating 'enum' in schema:
    OrderedDict([('title', 'Readout pattern'),
                 ('type', 'string'),
                 ('enum',
                  ['ACQ1',
                   'ACQ2',
                   'BRIGHT1',
                   'BRIGHT2',
                   'DEEP2',
                   'DEEP8',
                   'FAST',
                   'FASTGRPAVG',
                   'FASTGRPAVG8',
                   'FASTGRPAVG16',
                   'FASTGRPAVG32',
                   'FASTGRPAVG64',
                   'FASTR1',
                   'FASTR100',
                   'FGS',
                   'FGS60',
                   'FGS8370',
                   'FGS840',
                   'FGSRAPID',
                   'FINEGUIDE',
                   'ID',
                   'MEDIUM2',
                   'MEDIUM8',
                   'NIS',
                   'NISRAPID',
                   'NRS',
                   'NRSIRS2',
                   'NRSN16R4',
                   'NRSN32R8',
                   'NRSN8R2',
                   'NRSRAPID',
                   'NRSIRS2RAPID',
                   'NRSRAPIDD1',
                   'NRSRAPIDD2',
                   'NRSRAPIDD6',
                   'NRSSLOW',
                   'RAPID',
                   'SHALLOW2',
                   'SHALLOW4',
                   'SLOW',
                   'SLOWR1',
                   'TRACK',
                   'ANY',
                   'N/A']),
                 ('fits_ke ...
  warnings.warn(errmsg, ValidationWarning)

2021-03-13 00:09:20,254 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2021-03-13 00:09:20,344 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:20,346 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2021-03-13 00:09:20,362 - stpipe.Detector1Pipeline.refpix - INFO - Using refpix reference file: /grp/crds/cache/references/jwst/jwst_nirspec_refpix_0022.fits
2021-03-13 00:09:34,121 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2021-03-13 00:09:34,367 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:34,368 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:34,385 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0018.fits
2021-03-13 00:09:34,994 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2021-03-13 00:09:35,094 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:35,095 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'dark_output': None}
2021-03-13 00:09:35,112 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0086.fits
2021-03-13 00:09:38,371 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=4, nframes=1, groupgap=0
2021-03-13 00:09:38,372 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=65, nframes=1, groupgap=0
2021-03-13 00:09:38,831 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2021-03-13 00:09:39,335 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:39,337 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}
2021-03-13 00:09:39,345 - stpipe.Detector1Pipeline.jump - WARNING - Can not apply jump detection when NGROUPS<=4;
2021-03-13 00:09:39,345 - stpipe.Detector1Pipeline.jump - WARNING - Jump step will be skipped
2021-03-13 00:09:39,401 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2021-03-13 00:09:39,484 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:39,485 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}
2021-03-13 00:09:39,549 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0018.fits
2021-03-13 00:09:39,589 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2021-03-13 00:09:39,628 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2021-03-13 00:09:39,629 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
2021-03-13 00:09:50,710 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 4
2021-03-13 00:09:50,712 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2021-03-13 00:09:50,719 - stpipe.Detector1Pipeline.ramp_fit - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/jwst/ramp_fitting/ramp_fit.py:1091: RuntimeWarning: divide by zero encountered in true_divide
  var_p2 = 1/(s_inv_var_p3.sum(axis=0))

2021-03-13 00:09:50,821 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2021-03-13 00:09:50,919 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:50,920 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:50,961 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:09:50,961 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:09:50,963 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:09:51,036 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:51,037 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:09:51,083 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:09:51,084 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:09:51,085 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:09:51,086 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2021-03-13 00:09:51,087 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2021-03-13 00:09:51,095 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2021-03-13 00:09:51,204 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:51,205 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.25, 'sip_degree': None, 'sip_max_inv_pix_error': 0.25, 'sip_inv_degree': None, 'sip_npoints': 32, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2021-03-13 00:09:51,370 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2021-03-13 00:09:51,389 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2021-03-13 00:09:51,390 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2021-03-13 00:09:51,391 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2021-03-13 00:09:51,392 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:09:51,581 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS1: [3, 4]
2021-03-13 00:09:51,582 - stpipe.AssignWcsStep - INFO - Computing WCS for 2 open slitlets
2021-03-13 00:09:51,594 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2021-03-13 00:09:51,595 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2021-03-13 00:09:51,596 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2021-03-13 00:09:51,597 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:09:51,604 - stpipe.AssignWcsStep - INFO - SPORDER= 0, wrange=[6e-07, 5.3e-06]
2021-03-13 00:09:51,692 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 1
2021-03-13 00:09:51,693 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 2
2021-03-13 00:09:51,693 - stpipe.AssignWcsStep - INFO - There are 1 open slits in quadrant 3
2021-03-13 00:09:51,702 - stpipe.AssignWcsStep - INFO - There are 1 open slits in quadrant 4
2021-03-13 00:09:51,712 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 5
2021-03-13 00:09:51,813 - stpipe.AssignWcsStep - INFO - Created a NIRSPEC nrs_msaspec pipeline with references {'distortion': None, 'filteroffset': None, 'specwcs': None, 'regions': None, 'wavelengthrange': '/grp/crds/cache/references/jwst/jwst_nirspec_wavelengthrange_0004.asdf', 'camera': '/grp/crds/cache/references/jwst/jwst_nirspec_camera_0004.asdf', 'collimator': '/grp/crds/cache/references/jwst/jwst_nirspec_collimator_0004.asdf', 'disperser': '/grp/crds/cache/references/jwst/jwst_nirspec_disperser_0034.asdf', 'fore': '/grp/crds/cache/references/jwst/jwst_nirspec_fore_0028.asdf', 'fpa': '/grp/crds/cache/references/jwst/jwst_nirspec_fpa_0005.asdf', 'msa': '/grp/crds/cache/references/jwst/jwst_nirspec_msa_0005.asdf', 'ote': '/grp/crds/cache/references/jwst/jwst_nirspec_ote_0005.asdf', 'ifupost': None, 'ifufore': None, 'ifuslicer': None, 'msametafile': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/V0030006000104_msa.fits'}
2021-03-13 00:09:51,938 - stpipe.AssignWcsStep - INFO - COMPLETED assign_wcs
2021-03-13 00:09:51,941 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep done
2021-03-13 00:09:51,948 - stpipe.MSAFlagOpenStep - INFO - MSAFlagOpenStep instance created.
2021-03-13 00:09:52,037 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:09:52,038 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2021-03-13 00:09:52,053 - stpipe.MSAFlagOpenStep - INFO - Using reference file /grp/crds/cache/references/jwst/jwst_nirspec_msaoper_0001.json
2021-03-13 00:09:52,054 - stpipe.JwstStep - INFO - JwstStep instance created.
2021-03-13 00:09:52,156 - stpipe.MSAFlagOpenStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2021-03-13 00:09:52,157 - stpipe.MSAFlagOpenStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2021-03-13 00:09:52,158 - stpipe.MSAFlagOpenStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2021-03-13 00:09:52,158 - stpipe.MSAFlagOpenStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:09:52,165 - stpipe.MSAFlagOpenStep - INFO - SPORDER= 0, wrange=[6e-07, 5.3e-06]
2021-03-13 00:09:52,254 - stpipe.MSAFlagOpenStep - INFO - There are 5 open slits in quadrant 1
2021-03-13 00:09:52,294 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 2
2021-03-13 00:09:52,319 - stpipe.MSAFlagOpenStep - INFO - There are 9 open slits in quadrant 3
2021-03-13 00:09:52,394 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 4
2021-03-13 00:09:52,420 - stpipe.MSAFlagOpenStep - INFO - There are 0 open slits in quadrant 5
2021-03-13 00:09:54,417 - stpipe.MSAFlagOpenStep - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/gwcs/geometry.py:203: RuntimeWarning: invalid value encountered in remainder
  lon = np.mod(lon, 360.0 * u.deg if nquant else 360.0)

2021-03-13 00:10:02,237 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep done
2021-03-13 00:10:02,246 - stpipe.Extract2dStep - INFO - Extract2dStep instance created.
2021-03-13 00:10:02,386 - stpipe.Extract2dStep - INFO - Step Extract2dStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:10:02,387 - stpipe.Extract2dStep - INFO - Step Extract2dStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'slit_name': None, 'extract_orders': None, 'tsgrism_extract_height': None, 'wfss_extract_half_height': 5, 'grism_objects': None, 'mmag_extract': 99.0}
2021-03-13 00:10:02,403 - stpipe.Extract2dStep - INFO - EXP_TYPE is NRS_MSASPEC
2021-03-13 00:10:02,550 - stpipe.Extract2dStep - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/gwcs/utils.py:72: DeprecationWarning: `np.int` is a deprecated alias for the builtin `int`. To silence this warning, use `int` by itself. Doing this will not modify any behavior and is safe. When replacing `np.int`, you may wish to use e.g. `np.int64` or `np.int32` to specify the precision. If you wish to review your current use, check the release note link for additional information.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  indx = np.asarray(np.floor(np.asarray(value) + 0.5), dtype=np.int)

2021-03-13 00:10:02,551 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 3
2021-03-13 00:10:02,552 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1027 1464
2021-03-13 00:10:02,552 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1971 1983
2021-03-13 00:10:02,654 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:10:02,662 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.216281195 -45.702862740 156.216151591 -45.702738206 156.216089149 -45.702770462 156.216218751 -45.702894998
2021-03-13 00:10:02,662 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.216281195 -45.702862740 156.216151591 -45.702738206 156.216089149 -45.702770462 156.216218751 -45.702894998
2021-03-13 00:10:02,787 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 4
2021-03-13 00:10:02,788 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1275 1699
2021-03-13 00:10:02,788 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 32 43
2021-03-13 00:10:02,886 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:10:02,894 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.168120618 -45.657220874 156.167995139 -45.657100409 156.167933468 -45.657132147 156.168058946 -45.657252613
2021-03-13 00:10:02,895 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.168120618 -45.657220874 156.167995139 -45.657100409 156.167933468 -45.657132147 156.168058946 -45.657252613
2021-03-13 00:10:02,946 - stpipe.Extract2dStep - INFO - Step Extract2dStep done
2021-03-13 00:10:03,147 - stpipe.SourceTypeStep - INFO - SourceTypeStep instance created.
2021-03-13 00:10:03,245 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:10:03,246 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2021-03-13 00:10:03,253 - stpipe.SourceTypeStep - INFO - Input EXP_TYPE is NRS_MSASPEC
2021-03-13 00:10:03,254 - stpipe.SourceTypeStep - INFO - source_id=3, stellarity=100.0000, type=POINT
2021-03-13 00:10:03,254 - stpipe.SourceTypeStep - INFO - source_id=4, stellarity=100.0000, type=POINT
2021-03-13 00:10:03,255 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep done
2021-03-13 00:10:03,268 - stpipe.FlatFieldStep - INFO - FlatFieldStep instance created.
2021-03-13 00:10:03,345 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:10:03,347 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_interpolated_flat': False, 'user_supplied_flat': None, 'inverse': False}
2021-03-13 00:10:25,841 - stpipe.FlatFieldStep - INFO - Working on slit 3
2021-03-13 00:10:26,494 - stpipe.FlatFieldStep - INFO - Working on slit 4
2021-03-13 00:10:27,166 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep done
2021-03-13 00:10:27,178 - stpipe.PathLossStep - INFO - PathLossStep instance created.
2021-03-13 00:10:27,431 - stpipe.PathLossStep - INFO - Step PathLossStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:10:27,432 - stpipe.PathLossStep - INFO - Step PathLossStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2021-03-13 00:10:27,452 - stpipe.PathLossStep - INFO - Using PATHLOSS reference file /grp/crds/cache/references/jwst/jwst_nirspec_pathloss_0002.fits
2021-03-13 00:10:27,480 - stpipe.PathLossStep - INFO - Input exposure type is NRS_MSASPEC
2021-03-13 00:10:27,737 - stpipe.PathLossStep - INFO - Working on slit 0
2021-03-13 00:10:27,747 - stpipe.PathLossStep - INFO - Working on slit 1
2021-03-13 00:10:27,758 - stpipe.PathLossStep - INFO - Step PathLossStep done
2021-03-13 00:10:27,770 - stpipe.BarShadowStep - INFO - BarShadowStep instance created.
2021-03-13 00:10:27,866 - stpipe.BarShadowStep - INFO - Step BarShadowStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2021-03-13 00:10:27,867 - stpipe.BarShadowStep - INFO - Step BarShadowStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2021-03-13 00:10:27,886 - stpipe.BarShadowStep - INFO - Using BARSHADOW reference file /grp/crds/cache/references/jwst/jwst_nirspec_barshadow_0001.fits
2021-03-13 00:10:28,166 - stpipe.BarShadowStep - INFO - Working on slitlet 3
2021-03-13 00:10:28,174 - stpipe.BarShadowStep - INFO - Bar shadow correction skipped for slitlet 3 (source not uniform)
2021-03-13 00:10:28,177 - stpipe.BarShadowStep - INFO - Working on slitlet 4
2021-03-13 00:10:28,184 - stpipe.BarShadowStep - INFO - Bar shadow correction skipped for slitlet 4 (source not uniform)
2021-03-13 00:10:28,187 - stpipe.BarShadowStep - INFO - Step BarShadowStep done

Looping over open slitlets...
Working with slitlet  3
Slitlet name in fits file previous to barshadow and in barshadow output file are the same.
Did barshadow validation test passed?  The test is skipped for POINT sources, since the correction is not applied 


Testing files for detector:  nrs2
Working with uncal_file:  /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_prism_nrs2_uncal.fits

2021-03-13 00:10:29,068 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2021-03-13 00:10:29,069 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2021-03-13 00:10:29,070 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2021-03-13 00:10:29,071 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2021-03-13 00:10:29,072 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2021-03-13 00:10:29,073 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2021-03-13 00:10:29,074 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2021-03-13 00:10:29,076 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2021-03-13 00:10:29,077 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2021-03-13 00:10:29,078 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2021-03-13 00:10:29,079 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2021-03-13 00:10:29,080 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2021-03-13 00:10:29,081 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2021-03-13 00:10:29,082 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2021-03-13 00:10:29,083 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2021-03-13 00:10:29,084 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2021-03-13 00:10:29,085 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2021-03-13 00:10:29,202 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/stpipe/step.py:359: ResourceWarning: unclosed file <_io.FileIO name='/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_prism_nrs2_uncal.fits' mode='rb' closefd=True>
  gc.collect()

2021-03-13 00:10:29,206 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_prism_nrs2_uncal.fits',).
2021-03-13 00:10:29,215 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2021-03-13 00:10:29,298 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_prism_nrs2_uncal.fits' reftypes = ['dark', 'gain', 'ipc', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2021-03-13 00:10:29,314 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0087.fits'.
2021-03-13 00:10:29,319 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0018.fits'.
2021-03-13 00:10:29,322 - stpipe.Detector1Pipeline - INFO - Prefetch for IPC reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_ipc_0012.fits'.
2021-03-13 00:10:29,323 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0021.fits'.
2021-03-13 00:10:29,325 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0011.fits'.
2021-03-13 00:10:29,327 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2021-03-13 00:10:29,328 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0017.fits'.
2021-03-13 00:10:29,329 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_refpix_0020.fits'.
2021-03-13 00:10:29,332 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2021-03-13 00:10:29,332 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2021-03-13 00:10:29,332 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0021.fits'.
2021-03-13 00:10:29,336 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0114.fits'.
2021-03-13 00:10:29,338 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2021-03-13 00:10:29,339 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2021-03-13 00:10:29,339 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2021-03-13 00:10:29,633 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:29,635 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:29,762 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2021-03-13 00:10:29,762 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2021-03-13 00:10:29,763 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2021-03-13 00:10:29,866 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:29,868 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:29,884 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0011.fits
2021-03-13 00:10:30,233 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2021-03-13 00:10:30,339 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:30,340 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:30,357 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0021.fits
2021-03-13 00:10:30,954 - stpipe.Detector1Pipeline.saturation - INFO - Detected 5379 saturated pixels
2021-03-13 00:10:30,976 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2021-03-13 00:10:31,000 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2021-03-13 00:10:31,128 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:31,130 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:31,146 - stpipe.Detector1Pipeline.ipc - INFO - Using IPC reference file /grp/crds/cache/references/jwst/jwst_nirspec_ipc_0012.fits
2021-03-13 00:10:31,676 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2021-03-13 00:10:31,805 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:31,806 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:31,823 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0114.fits
2021-03-13 00:10:31,865 - stpipe.Detector1Pipeline.superbias - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/stdatamodels/validate.py:34: ValidationWarning: While validating meta.exposure.readpatt the following error occurred:
'ALLIRS2' is not one of ['ACQ1', 'ACQ2', 'BRIGHT1', 'BRIGHT2', 'DEEP2', 'DEEP8', 'FAST', 'FASTGRPAVG', 'FASTGRPAVG8', 'FASTGRPAVG16', 'FASTGRPAVG32', 'FASTGRPAVG64', 'FASTR1', 'FASTR100', 'FGS', 'FGS60', 'FGS8370', 'FGS840', 'FGSRAPID', 'FINEGUIDE', 'ID', 'MEDIUM2', 'MEDIUM8', 'NIS', 'NISRAPID', 'NRS', 'NRSIRS2', 'NRSN16R4', 'NRSN32R8', 'NRSN8R2', 'NRSRAPID', 'NRSIRS2RAPID', 'NRSRAPIDD1', 'NRSRAPIDD2', 'NRSRAPIDD6', 'NRSSLOW', 'RAPID', 'SHALLOW2', 'SHALLOW4', 'SLOW', 'SLOWR1', 'TRACK', 'ANY', 'N/A']

Failed validating 'enum' in schema:
    OrderedDict([('title', 'Readout pattern'),
                 ('type', 'string'),
                 ('enum',
                  ['ACQ1',
                   'ACQ2',
                   'BRIGHT1',
                   'BRIGHT2',
                   'DEEP2',
                   'DEEP8',
                   'FAST',
                   'FASTGRPAVG',
                   'FASTGRPAVG8',
                   'FASTGRPAVG16',
                   'FASTGRPAVG32',
                   'FASTGRPAVG64',
                   'FASTR1',
                   'FASTR100',
                   'FGS',
                   'FGS60',
                   'FGS8370',
                   'FGS840',
                   'FGSRAPID',
                   'FINEGUIDE',
                   'ID',
                   'MEDIUM2',
                   'MEDIUM8',
                   'NIS',
                   'NISRAPID',
                   'NRS',
                   'NRSIRS2',
                   'NRSN16R4',
                   'NRSN32R8',
                   'NRSN8R2',
                   'NRSRAPID',
                   'NRSIRS2RAPID',
                   'NRSRAPIDD1',
                   'NRSRAPIDD2',
                   'NRSRAPIDD6',
                   'NRSSLOW',
                   'RAPID',
                   'SHALLOW2',
                   'SHALLOW4',
                   'SLOW',
                   'SLOWR1',
                   'TRACK',
                   'ANY',
                   'N/A']),
                 ('fits_ke ...
  warnings.warn(errmsg, ValidationWarning)

2021-03-13 00:10:32,222 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2021-03-13 00:10:32,347 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:32,349 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2021-03-13 00:10:32,365 - stpipe.Detector1Pipeline.refpix - INFO - Using refpix reference file: /grp/crds/cache/references/jwst/jwst_nirspec_refpix_0020.fits
2021-03-13 00:10:46,034 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2021-03-13 00:10:46,262 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:46,263 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:10:46,280 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0021.fits
2021-03-13 00:10:46,829 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2021-03-13 00:10:46,960 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:46,961 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'dark_output': None}
2021-03-13 00:10:46,977 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0087.fits
2021-03-13 00:10:50,371 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=4, nframes=1, groupgap=0
2021-03-13 00:10:50,371 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=65, nframes=1, groupgap=0
2021-03-13 00:10:50,766 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2021-03-13 00:10:51,278 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:51,279 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}
2021-03-13 00:10:51,287 - stpipe.Detector1Pipeline.jump - WARNING - Can not apply jump detection when NGROUPS<=4;
2021-03-13 00:10:51,288 - stpipe.Detector1Pipeline.jump - WARNING - Jump step will be skipped
2021-03-13 00:10:51,371 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2021-03-13 00:10:51,472 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:10:51,474 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}
2021-03-13 00:10:51,499 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0017.fits
2021-03-13 00:10:51,531 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0018.fits
2021-03-13 00:10:51,564 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2021-03-13 00:10:51,565 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
2021-03-13 00:11:02,266 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 4
2021-03-13 00:11:02,267 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2021-03-13 00:11:02,274 - stpipe.Detector1Pipeline.ramp_fit - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/jwst/ramp_fitting/ramp_fit.py:1091: RuntimeWarning: divide by zero encountered in true_divide
  var_p2 = 1/(s_inv_var_p3.sum(axis=0))

2021-03-13 00:11:02,381 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2021-03-13 00:11:02,492 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:11:02,494 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:02,546 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:11:02,546 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:11:02,547 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:11:02,647 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:11:02,649 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:02,695 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:11:02,696 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:11:02,697 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:11:02,697 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2021-03-13 00:11:02,698 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2021-03-13 00:11:02,706 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2021-03-13 00:11:02,814 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2021-03-13 00:11:02,816 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.25, 'sip_degree': None, 'sip_max_inv_pix_error': 0.25, 'sip_inv_degree': None, 'sip_npoints': 32, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2021-03-13 00:11:02,939 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2021-03-13 00:11:02,954 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2021-03-13 00:11:02,955 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2021-03-13 00:11:02,955 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2021-03-13 00:11:02,956 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:11:03,095 - stpipe.AssignWcsStep - INFO - Removing slit 3 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:03,133 - stpipe.AssignWcsStep - INFO - Removing slit 4 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:03,134 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS2: []
2021-03-13 00:11:03,134 - stpipe.AssignWcsStep - CRITICAL - No open slits fall on detector NRS2.

No open slits fall on detector  nrs2 

Testing files for detector:  nrs1
Working with uncal_file:  /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_g140m_line1_NRS1_uncal.fits

2021-03-13 00:11:03,836 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2021-03-13 00:11:03,837 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2021-03-13 00:11:03,838 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2021-03-13 00:11:03,839 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2021-03-13 00:11:03,840 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2021-03-13 00:11:03,841 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2021-03-13 00:11:03,842 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2021-03-13 00:11:03,843 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2021-03-13 00:11:03,844 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2021-03-13 00:11:03,845 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2021-03-13 00:11:03,846 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2021-03-13 00:11:03,847 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2021-03-13 00:11:03,848 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2021-03-13 00:11:03,849 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2021-03-13 00:11:03,850 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2021-03-13 00:11:03,851 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2021-03-13 00:11:03,852 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2021-03-13 00:11:03,969 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/stpipe/step.py:359: ResourceWarning: unclosed file <_io.FileIO name='/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_g140m_line1_NRS1_uncal.fits' mode='rb' closefd=True>
  gc.collect()

2021-03-13 00:11:03,976 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k/mos_g140m_line1_NRS1_uncal.fits',).
2021-03-13 00:11:03,985 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2021-03-13 00:11:04,060 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_g140m_line1_NRS1_uncal.fits' reftypes = ['dark', 'gain', 'ipc', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2021-03-13 00:11:04,073 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0140.fits'.
2021-03-13 00:11:04,074 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits'.
2021-03-13 00:11:04,075 - stpipe.Detector1Pipeline - INFO - Prefetch for IPC reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_ipc_0011.fits'.
2021-03-13 00:11:04,076 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0019.fits'.
2021-03-13 00:11:04,077 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0024.fits'.
2021-03-13 00:11:04,078 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2021-03-13 00:11:04,078 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits'.
2021-03-13 00:11:04,079 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is 'N/A'.
2021-03-13 00:11:04,080 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2021-03-13 00:11:04,080 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2021-03-13 00:11:04,080 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0023.fits'.
2021-03-13 00:11:04,081 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0087.fits'.
2021-03-13 00:11:04,082 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2021-03-13 00:11:04,083 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2021-03-13 00:11:04,083 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2021-03-13 00:11:04,379 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:04,380 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:04,501 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2021-03-13 00:11:04,501 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2021-03-13 00:11:04,502 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2021-03-13 00:11:04,602 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:04,603 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:04,619 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0024.fits
2021-03-13 00:11:04,902 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2021-03-13 00:11:05,006 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:05,007 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:05,023 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0023.fits
2021-03-13 00:11:06,083 - stpipe.Detector1Pipeline.saturation - INFO - Detected 58922 saturated pixels
2021-03-13 00:11:06,103 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2021-03-13 00:11:06,110 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2021-03-13 00:11:06,212 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:06,214 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:06,229 - stpipe.Detector1Pipeline.ipc - INFO - Using IPC reference file /grp/crds/cache/references/jwst/jwst_nirspec_ipc_0011.fits
2021-03-13 00:11:06,728 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2021-03-13 00:11:06,831 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:06,832 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:06,848 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0087.fits
2021-03-13 00:11:09,019 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2021-03-13 00:11:09,122 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:09,124 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2021-03-13 00:11:09,131 - stpipe.Detector1Pipeline.refpix - INFO - use_side_ref_pixels = True
2021-03-13 00:11:09,131 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_columns = True
2021-03-13 00:11:09,132 - stpipe.Detector1Pipeline.refpix - INFO - side_smoothing_length = 11
2021-03-13 00:11:09,132 - stpipe.Detector1Pipeline.refpix - INFO - side_gain = 1.000000
2021-03-13 00:11:09,132 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_rows = True
2021-03-13 00:11:12,746 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2021-03-13 00:11:12,849 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:12,851 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:12,867 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0019.fits
2021-03-13 00:11:17,175 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2021-03-13 00:11:17,285 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:17,286 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'dark_output': None}
2021-03-13 00:11:17,302 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0140.fits
2021-03-13 00:11:21,433 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=6, nframes=1, groupgap=0
2021-03-13 00:11:21,434 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=10, nframes=1, groupgap=0
2021-03-13 00:11:21,609 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2021-03-13 00:11:21,725 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:21,727 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'rejection_threshold': 4.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 200.0, 'min_jump_to_flag_neighbors': 10.0}
2021-03-13 00:11:21,734 - stpipe.Detector1Pipeline.jump - INFO - CR rejection threshold = 4 sigma
2021-03-13 00:11:21,743 - stpipe.Detector1Pipeline.jump - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2021-03-13 00:11:21,778 - stpipe.Detector1Pipeline.jump - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits
2021-03-13 00:11:22,649 - stpipe.Detector1Pipeline.jump - INFO - Found 32 possible cores to use for jump detection 
2021-03-13 00:11:22,801 - stpipe.Detector1Pipeline.jump - INFO - Executing two-point difference method
2021-03-13 00:11:23,030 - stpipe.Detector1Pipeline.jump - INFO - Working on integration 1:
2021-03-13 00:11:24,563 - stpipe.Detector1Pipeline.jump - INFO - From highest outlier Two-point found 72408 pixels with at least one CR
2021-03-13 00:11:27,441 - stpipe.Detector1Pipeline.jump - INFO - Total elapsed time = 4.63949 sec
2021-03-13 00:11:27,443 - stpipe.Detector1Pipeline.jump - INFO - The execution time in seconds: 5.708970
2021-03-13 00:11:27,444 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2021-03-13 00:11:27,553 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:27,555 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k', 'int_name': '', 'save_opt': False, 'opt_name': '', 'maximum_cores': 'none'}
2021-03-13 00:11:27,582 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits
2021-03-13 00:11:27,609 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2021-03-13 00:11:27,636 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2021-03-13 00:11:27,637 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
2021-03-13 00:11:50,724 - stpipe.Detector1Pipeline.ramp_fit - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/jwst/ramp_fitting/ramp_fit.py:872: RuntimeWarning: invalid value encountered in multiply
  var_p4[num_int,:,:,:] *= ( segs_4[num_int,:,:,:] > 0)

2021-03-13 00:11:51,424 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 6
2021-03-13 00:11:51,424 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2021-03-13 00:11:51,551 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2021-03-13 00:11:51,677 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:51,679 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:51,720 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:11:51,720 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:11:51,721 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:11:51,819 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:51,821 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpw0clnv3k'}
2021-03-13 00:11:51,865 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2021-03-13 00:11:51,865 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2021-03-13 00:11:51,866 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2021-03-13 00:11:51,867 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2021-03-13 00:11:51,868 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2021-03-13 00:11:51,876 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2021-03-13 00:11:51,981 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:51,982 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.25, 'sip_degree': None, 'sip_max_inv_pix_error': 0.25, 'sip_inv_degree': None, 'sip_npoints': 32, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2021-03-13 00:11:52,127 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2021-03-13 00:11:52,340 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2021-03-13 00:11:52,340 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2021-03-13 00:11:52,341 - stpipe.AssignWcsStep - INFO - theta_y correction: 0.0002496099796717191 deg
2021-03-13 00:11:52,341 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:11:52,455 - stpipe.AssignWcsStep - INFO - Removing slit 6 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,468 - stpipe.AssignWcsStep - INFO - Removing slit 7 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,481 - stpipe.AssignWcsStep - INFO - Removing slit 8 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,493 - stpipe.AssignWcsStep - INFO - Removing slit 9 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,506 - stpipe.AssignWcsStep - INFO - Removing slit 10 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,519 - stpipe.AssignWcsStep - INFO - Removing slit 11 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,532 - stpipe.AssignWcsStep - INFO - Removing slit 14 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,545 - stpipe.AssignWcsStep - INFO - Removing slit 15 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,557 - stpipe.AssignWcsStep - INFO - Removing slit 16 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,570 - stpipe.AssignWcsStep - INFO - Removing slit 17 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,583 - stpipe.AssignWcsStep - INFO - Removing slit 18 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,596 - stpipe.AssignWcsStep - INFO - Removing slit 19 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,609 - stpipe.AssignWcsStep - INFO - Removing slit 21 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,621 - stpipe.AssignWcsStep - INFO - Removing slit 25 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,634 - stpipe.AssignWcsStep - INFO - Removing slit 26 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,647 - stpipe.AssignWcsStep - INFO - Removing slit 27 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,660 - stpipe.AssignWcsStep - INFO - Removing slit 29 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,672 - stpipe.AssignWcsStep - INFO - Removing slit 31 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,685 - stpipe.AssignWcsStep - INFO - Removing slit 32 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,698 - stpipe.AssignWcsStep - INFO - Removing slit 33 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,711 - stpipe.AssignWcsStep - INFO - Removing slit 35 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,723 - stpipe.AssignWcsStep - INFO - Removing slit 37 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,736 - stpipe.AssignWcsStep - INFO - Removing slit 38 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,749 - stpipe.AssignWcsStep - INFO - Removing slit 39 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,762 - stpipe.AssignWcsStep - INFO - Removing slit 41 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,813 - stpipe.AssignWcsStep - INFO - Removing slit 1 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,826 - stpipe.AssignWcsStep - INFO - Removing slit 2 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,839 - stpipe.AssignWcsStep - INFO - Removing slit 3 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,852 - stpipe.AssignWcsStep - INFO - Removing slit 4 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,864 - stpipe.AssignWcsStep - INFO - Removing slit 5 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,881 - stpipe.AssignWcsStep - INFO - Removing slit 12 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,894 - stpipe.AssignWcsStep - INFO - Removing slit 13 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,907 - stpipe.AssignWcsStep - INFO - Removing slit 20 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,919 - stpipe.AssignWcsStep - INFO - Removing slit 22 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,932 - stpipe.AssignWcsStep - INFO - Removing slit 23 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,945 - stpipe.AssignWcsStep - INFO - Removing slit 24 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,959 - stpipe.AssignWcsStep - INFO - Removing slit 28 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,971 - stpipe.AssignWcsStep - INFO - Removing slit 30 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,984 - stpipe.AssignWcsStep - INFO - Removing slit 34 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:52,997 - stpipe.AssignWcsStep - INFO - Removing slit 36 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:53,010 - stpipe.AssignWcsStep - INFO - Removing slit 40 from the list of open slits because the WCS bounding_box is completely outside the detector.
2021-03-13 00:11:53,346 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS1: [42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68]
2021-03-13 00:11:53,346 - stpipe.AssignWcsStep - INFO - Computing WCS for 27 open slitlets
2021-03-13 00:11:53,357 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2021-03-13 00:11:53,358 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2021-03-13 00:11:53,358 - stpipe.AssignWcsStep - INFO - theta_y correction: 0.0002496099796717191 deg
2021-03-13 00:11:53,359 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:11:53,368 - stpipe.AssignWcsStep - INFO - SPORDER= -1, wrange=[9.7e-07, 1.89e-06]
2021-03-13 00:11:53,460 - stpipe.AssignWcsStep - INFO - There are 2 open slits in quadrant 1
2021-03-13 00:11:53,477 - stpipe.AssignWcsStep - INFO - There are 11 open slits in quadrant 2
2021-03-13 00:11:53,567 - stpipe.AssignWcsStep - INFO - There are 4 open slits in quadrant 3
2021-03-13 00:11:53,600 - stpipe.AssignWcsStep - INFO - There are 10 open slits in quadrant 4
2021-03-13 00:11:53,684 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 5
2021-03-13 00:11:53,922 - stpipe.AssignWcsStep - INFO - Created a NIRSPEC nrs_msaspec pipeline with references {'distortion': None, 'filteroffset': None, 'specwcs': None, 'regions': None, 'wavelengthrange': '/grp/crds/cache/references/jwst/jwst_nirspec_wavelengthrange_0004.asdf', 'camera': '/grp/crds/cache/references/jwst/jwst_nirspec_camera_0004.asdf', 'collimator': '/grp/crds/cache/references/jwst/jwst_nirspec_collimator_0004.asdf', 'disperser': '/grp/crds/cache/references/jwst/jwst_nirspec_disperser_0032.asdf', 'fore': '/grp/crds/cache/references/jwst/jwst_nirspec_fore_0023.asdf', 'fpa': '/grp/crds/cache/references/jwst/jwst_nirspec_fpa_0005.asdf', 'msa': '/grp/crds/cache/references/jwst/jwst_nirspec_msa_0005.asdf', 'ote': '/grp/crds/cache/references/jwst/jwst_nirspec_ote_0005.asdf', 'ifupost': None, 'ifufore': None, 'ifuslicer': None, 'msametafile': 'V8460001000101_msa.fits'}
2021-03-13 00:11:54,303 - stpipe.AssignWcsStep - INFO - COMPLETED assign_wcs
2021-03-13 00:11:54,306 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep done
2021-03-13 00:11:54,314 - stpipe.MSAFlagOpenStep - INFO - MSAFlagOpenStep instance created.
2021-03-13 00:11:54,458 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:11:54,460 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2021-03-13 00:11:54,475 - stpipe.MSAFlagOpenStep - INFO - Using reference file /grp/crds/cache/references/jwst/jwst_nirspec_msaoper_0001.json
2021-03-13 00:11:54,476 - stpipe.JwstStep - INFO - JwstStep instance created.
2021-03-13 00:11:54,571 - stpipe.MSAFlagOpenStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2021-03-13 00:11:54,572 - stpipe.MSAFlagOpenStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2021-03-13 00:11:54,573 - stpipe.MSAFlagOpenStep - INFO - theta_y correction: 0.0002496099796717191 deg
2021-03-13 00:11:54,573 - stpipe.MSAFlagOpenStep - INFO - theta_x correction: 0.0 deg
2021-03-13 00:11:54,580 - stpipe.MSAFlagOpenStep - INFO - SPORDER= -1, wrange=[9.7e-07, 1.89e-06]
2021-03-13 00:11:54,670 - stpipe.MSAFlagOpenStep - INFO - There are 5 open slits in quadrant 1
2021-03-13 00:11:54,712 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 2
2021-03-13 00:11:54,737 - stpipe.MSAFlagOpenStep - INFO - There are 9 open slits in quadrant 3
2021-03-13 00:11:54,811 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 4
2021-03-13 00:11:54,836 - stpipe.MSAFlagOpenStep - INFO - There are 0 open slits in quadrant 5
2021-03-13 00:11:57,179 - stpipe.MSAFlagOpenStep - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/gwcs/geometry.py:203: RuntimeWarning: invalid value encountered in remainder
  lon = np.mod(lon, 360.0 * u.deg if nquant else 360.0)

2021-03-13 00:12:05,082 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep done
2021-03-13 00:12:05,090 - stpipe.Extract2dStep - INFO - Extract2dStep instance created.
2021-03-13 00:12:05,328 - stpipe.Extract2dStep - INFO - Step Extract2dStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:12:05,329 - stpipe.Extract2dStep - INFO - Step Extract2dStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'slit_name': None, 'extract_orders': None, 'tsgrism_extract_height': None, 'wfss_extract_half_height': 5, 'grism_objects': None, 'mmag_extract': 99.0}
2021-03-13 00:12:05,345 - stpipe.Extract2dStep - INFO - EXP_TYPE is NRS_MSASPEC
2021-03-13 00:12:05,777 - stpipe.Extract2dStep - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/gwcs/utils.py:72: DeprecationWarning: `np.int` is a deprecated alias for the builtin `int`. To silence this warning, use `int` by itself. Doing this will not modify any behavior and is safe. When replacing `np.int`, you may wish to use e.g. `np.int64` or `np.int32` to specify the precision. If you wish to review your current use, check the release note link for additional information.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  indx = np.asarray(np.floor(np.asarray(value) + 0.5), dtype=np.int)

2021-03-13 00:12:05,779 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 53
2021-03-13 00:12:05,779 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1542 2048
2021-03-13 00:12:05,779 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1315 1329
2021-03-13 00:12:05,879 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:05,887 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.226123221 -45.673642180 156.225994086 -45.673519691 156.225931834 -45.673551545 156.226060967 -45.673674035
2021-03-13 00:12:05,887 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.226123221 -45.673642180 156.225994086 -45.673519691 156.225931834 -45.673551545 156.226060967 -45.673674035
2021-03-13 00:12:06,448 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 54
2021-03-13 00:12:06,449 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1542 2048
2021-03-13 00:12:06,449 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1305 1319
2021-03-13 00:12:06,549 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:06,557 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.225872406 -45.673404272 156.225743296 -45.673281804 156.225681049 -45.673313656 156.225810156 -45.673436124
2021-03-13 00:12:06,557 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.225872406 -45.673404272 156.225743296 -45.673281804 156.225681049 -45.673313656 156.225810156 -45.673436124
2021-03-13 00:12:07,135 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 42
2021-03-13 00:12:07,135 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 2018 2048
2021-03-13 00:12:07,136 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 545 562
2021-03-13 00:12:07,231 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:07,240 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.223646010 -45.647128995 156.223518121 -45.647008321 156.223456024 -45.647039957 156.223583911 -45.647160632
2021-03-13 00:12:07,240 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.223646010 -45.647128995 156.223518121 -45.647008321 156.223456024 -45.647039957 156.223583911 -45.647160632
2021-03-13 00:12:07,822 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 43
2021-03-13 00:12:07,823 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1970 2048
2021-03-13 00:12:07,823 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 414 430
2021-03-13 00:12:07,918 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:07,925 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218966486 -45.644829601 156.218838959 -45.644709141 156.218776943 -45.644740759 156.218904467 -45.644861220
2021-03-13 00:12:07,926 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218966486 -45.644829601 156.218838959 -45.644709141 156.218776943 -45.644740759 156.218904467 -45.644861220
2021-03-13 00:12:08,343 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 44
2021-03-13 00:12:08,343 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1969 2048
2021-03-13 00:12:08,343 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 404 420
2021-03-13 00:12:08,611 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:08,620 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218718991 -45.644595818 156.218591488 -45.644475376 156.218529475 -45.644506992 156.218656977 -45.644627436
2021-03-13 00:12:08,620 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218718991 -45.644595818 156.218591488 -45.644475376 156.218529475 -45.644506992 156.218656977 -45.644627436
2021-03-13 00:12:09,040 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 45
2021-03-13 00:12:09,040 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1908 2048
2021-03-13 00:12:09,041 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 530 546
2021-03-13 00:12:09,136 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:09,143 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.219673020 -45.648613077 156.219545303 -45.648492383 156.219483265 -45.648524021 156.219610979 -45.648644716
2021-03-13 00:12:09,144 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.219673020 -45.648613077 156.219545303 -45.648492383 156.219483265 -45.648524021 156.219610979 -45.648644716
2021-03-13 00:12:09,732 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 46
2021-03-13 00:12:09,733 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1882 2048
2021-03-13 00:12:09,733 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 202 218
2021-03-13 00:12:09,828 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:09,835 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.211127421 -45.641279813 156.211000463 -45.641159678 156.210938572 -45.641191268 156.211065527 -45.641311404
2021-03-13 00:12:09,835 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.211127421 -45.641279813 156.211000463 -45.641159678 156.210938572 -45.641191268 156.211065527 -45.641311404
2021-03-13 00:12:10,425 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 47
2021-03-13 00:12:10,425 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1815 2048
2021-03-13 00:12:10,425 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 566 581
2021-03-13 00:12:10,522 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:10,529 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.217456055 -45.651006881 156.217328370 -45.650886079 156.217266356 -45.650917729 156.217394038 -45.651038531
2021-03-13 00:12:10,530 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.217456055 -45.651006881 156.217328370 -45.650886079 156.217266356 -45.650917729 156.217394038 -45.651038531
2021-03-13 00:12:10,947 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 48
2021-03-13 00:12:10,948 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1815 2048
2021-03-13 00:12:10,948 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 561 576
2021-03-13 00:12:11,045 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:11,052 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.217332149 -45.650889654 156.217204477 -45.650768862 156.217142464 -45.650800511 156.217270135 -45.650921304
2021-03-13 00:12:11,052 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.217332149 -45.650889654 156.217204477 -45.650768862 156.217142464 -45.650800511 156.217270135 -45.650921304
2021-03-13 00:12:11,669 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 49
2021-03-13 00:12:11,669 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1791 2048
2021-03-13 00:12:11,670 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 631 646
2021-03-13 00:12:11,771 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:11,778 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218210913 -45.652969013 156.218083107 -45.652848076 156.218021073 -45.652879740 156.218148877 -45.653000678
2021-03-13 00:12:11,779 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218210913 -45.652969013 156.218083107 -45.652848076 156.218021073 -45.652879740 156.218148877 -45.653000678
2021-03-13 00:12:12,386 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 50
2021-03-13 00:12:12,387 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1774 2048
2021-03-13 00:12:12,387 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 238 253
2021-03-13 00:12:12,483 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:12,491 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.208399869 -45.643929179 156.208272959 -45.643808942 156.208211096 -45.643840541 156.208338005 -45.643960778
2021-03-13 00:12:12,491 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.208399869 -45.643929179 156.208272959 -45.643808942 156.208211096 -45.643840541 156.208338005 -45.643960778
2021-03-13 00:12:12,906 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 51
2021-03-13 00:12:12,906 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1759 2048
2021-03-13 00:12:12,907 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 430 445
2021-03-13 00:12:13,004 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:13,011 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.212403238 -45.648718689 156.212275928 -45.648598111 156.212213993 -45.648629742 156.212341301 -45.648750320
2021-03-13 00:12:13,012 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.212403238 -45.648718689 156.212275928 -45.648598111 156.212213993 -45.648629742 156.212341301 -45.648750320
2021-03-13 00:12:13,647 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 52
2021-03-13 00:12:13,647 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1722 2048
2021-03-13 00:12:13,648 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 803 817
2021-03-13 00:12:13,744 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:13,752 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.219947139 -45.658234585 156.219819020 -45.658113276 156.219756938 -45.658144979 156.219885055 -45.658266289
2021-03-13 00:12:13,752 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.219947139 -45.658234585 156.219819020 -45.658113276 156.219756938 -45.658144979 156.219885055 -45.658266289
2021-03-13 00:12:14,172 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 55
2021-03-13 00:12:14,172 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1022 2048
2021-03-13 00:12:14,173 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1415 1430
2021-03-13 00:12:14,275 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:14,282 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.211226719 -45.684941334 156.211098073 -45.684818233 156.211035880 -45.684850241 156.211164524 -45.684973343
2021-03-13 00:12:14,283 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.211226719 -45.684941334 156.211098073 -45.684818233 156.211035880 -45.684850241 156.211164524 -45.684973343
2021-03-13 00:12:14,908 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 65
2021-03-13 00:12:14,908 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 427 1893
2021-03-13 00:12:14,909 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1251 1273
2021-03-13 00:12:15,022 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:15,029 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.187669449 -45.691221095 156.187541886 -45.691097893 156.187479754 -45.691130071 156.187607315 -45.691253274
2021-03-13 00:12:15,030 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.187669449 -45.691221095 156.187541886 -45.691097893 156.187479754 -45.691130071 156.187607315 -45.691253274
2021-03-13 00:12:15,654 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 66
2021-03-13 00:12:15,654 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 426 1892
2021-03-13 00:12:15,655 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1452 1474
2021-03-13 00:12:15,768 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:15,776 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.192290190 -45.696194513 156.192162195 -45.696070854 156.192099979 -45.696103094 156.192227972 -45.696226755
2021-03-13 00:12:15,776 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.192290190 -45.696194513 156.192162195 -45.696070854 156.192099979 -45.696103094 156.192227972 -45.696226755
2021-03-13 00:12:16,196 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 68
2021-03-13 00:12:16,197 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 375 1842
2021-03-13 00:12:16,197 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1476 1499
2021-03-13 00:12:16,312 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:16,319 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.191192483 -45.697686513 156.191064493 -45.697562756 156.191002259 -45.697595026 156.191130247 -45.697718784
2021-03-13 00:12:16,320 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.191192483 -45.697686513 156.191064493 -45.697562756 156.191002259 -45.697595026 156.191130247 -45.697718784
2021-03-13 00:12:16,968 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 56
2021-03-13 00:12:16,969 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 872 2048
2021-03-13 00:12:16,969 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 768 783
2021-03-13 00:12:17,073 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:17,080 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.191122501 -45.671742959 156.190995485 -45.671621176 156.190933579 -45.671653049 156.191060593 -45.671774833
2021-03-13 00:12:17,080 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.191122501 -45.671742959 156.190995485 -45.671621176 156.190933579 -45.671653049 156.191060593 -45.671774833
2021-03-13 00:12:17,504 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 57
2021-03-13 00:12:17,505 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 805 2048
2021-03-13 00:12:17,505 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 354 370
2021-03-13 00:12:17,609 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:17,617 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.179343124 -45.662963603 156.179216994 -45.662842617 156.179155236 -45.662874401 156.179281365 -45.662995389
2021-03-13 00:12:17,617 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.179343124 -45.662963603 156.179216994 -45.662842617 156.179155236 -45.662874401 156.179281365 -45.662995389
2021-03-13 00:12:18,267 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 58
2021-03-13 00:12:18,268 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 731 2048
2021-03-13 00:12:18,268 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 258 274
2021-03-13 00:12:18,374 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:18,382 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.174716949 -45.661919476 156.174591057 -45.661798624 156.174529324 -45.661830406 156.174655215 -45.661951259
2021-03-13 00:12:18,382 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.174716949 -45.661919476 156.174591057 -45.661798624 156.174529324 -45.661830406 156.174655215 -45.661951259
2021-03-13 00:12:18,804 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 59
2021-03-13 00:12:18,804 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 658 2048
2021-03-13 00:12:18,805 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 71 88
2021-03-13 00:12:18,911 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:18,919 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.167987333 -45.658726530 156.167861814 -45.658605973 156.167800128 -45.658637729 156.167925645 -45.658758288
2021-03-13 00:12:18,919 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.167987333 -45.658726530 156.167861814 -45.658605973 156.167800128 -45.658637729 156.167925645 -45.658758288
2021-03-13 00:12:19,571 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 60
2021-03-13 00:12:19,572 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 641 2048
2021-03-13 00:12:19,572 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 681 699
2021-03-13 00:12:19,680 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:19,688 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.181507045 -45.673611447 156.181380443 -45.673489678 156.181318559 -45.673521602 156.181445158 -45.673643373
2021-03-13 00:12:19,688 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.181507045 -45.673611447 156.181380443 -45.673489678 156.181318559 -45.673521602 156.181445158 -45.673643373
2021-03-13 00:12:20,111 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 61
2021-03-13 00:12:20,112 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 620 2048
2021-03-13 00:12:20,112 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 822 840
2021-03-13 00:12:20,219 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:20,227 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.184095390 -45.677365774 156.183968526 -45.677243686 156.183906587 -45.677275659 156.184033450 -45.677397747
2021-03-13 00:12:20,227 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.184095390 -45.677365774 156.183968526 -45.677243686 156.183906587 -45.677275659 156.184033450 -45.677397747
2021-03-13 00:12:20,880 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 62
2021-03-13 00:12:20,881 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 570 2032
2021-03-13 00:12:20,881 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 510 528
2021-03-13 00:12:20,989 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:20,997 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.175200333 -45.670700849 156.175074128 -45.670579384 156.175012293 -45.670611285 156.175138497 -45.670732752
2021-03-13 00:12:20,997 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.175200333 -45.670700849 156.175074128 -45.670579384 156.175012293 -45.670611285 156.175138497 -45.670732752
2021-03-13 00:12:21,415 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 63
2021-03-13 00:12:21,416 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 454 1915
2021-03-13 00:12:21,416 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 181 200
2021-03-13 00:12:21,526 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:21,533 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.163846800 -45.664818400 156.163721256 -45.664697497 156.163659498 -45.664729348 156.163785040 -45.664850252
2021-03-13 00:12:21,534 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.163846800 -45.664818400 156.163721256 -45.664697497 156.163659498 -45.664729348 156.163785040 -45.664850252
2021-03-13 00:12:22,190 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 64
2021-03-13 00:12:22,190 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 454 1915
2021-03-13 00:12:22,190 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 176 195
2021-03-13 00:12:22,299 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:22,306 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.163724974 -45.664701077 156.163599439 -45.664580184 156.163537682 -45.664612033 156.163663216 -45.664732928
2021-03-13 00:12:22,307 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.163724974 -45.664701077 156.163599439 -45.664580184 156.163537682 -45.664612033 156.163663216 -45.664732928
2021-03-13 00:12:22,721 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 67
2021-03-13 00:12:22,722 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 328 1789
2021-03-13 00:12:22,722 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 130 150
2021-03-13 00:12:23,072 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2021-03-13 00:12:23,080 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.158533940 -45.665758025 156.158408563 -45.665637125 156.158346784 -45.665669007 156.158472159 -45.665789909
2021-03-13 00:12:23,080 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.158533940 -45.665758025 156.158408563 -45.665637125 156.158346784 -45.665669007 156.158472159 -45.665789909
2021-03-13 00:12:23,781 - stpipe.Extract2dStep - INFO - Step Extract2dStep done
2021-03-13 00:12:26,199 - stpipe.SourceTypeStep - INFO - SourceTypeStep instance created.
2021-03-13 00:12:26,416 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:12:26,418 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2021-03-13 00:12:26,424 - stpipe.SourceTypeStep - INFO - Input EXP_TYPE is NRS_MSASPEC
2021-03-13 00:12:26,425 - stpipe.SourceTypeStep - INFO - source_id=53, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,426 - stpipe.SourceTypeStep - INFO - source_id=54, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,426 - stpipe.SourceTypeStep - INFO - source_id=42, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,427 - stpipe.SourceTypeStep - INFO - source_id=43, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,427 - stpipe.SourceTypeStep - INFO - source_id=44, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,428 - stpipe.SourceTypeStep - INFO - source_id=45, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,428 - stpipe.SourceTypeStep - INFO - source_id=46, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,429 - stpipe.SourceTypeStep - INFO - source_id=47, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,429 - stpipe.SourceTypeStep - INFO - source_id=48, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,430 - stpipe.SourceTypeStep - INFO - source_id=49, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,430 - stpipe.SourceTypeStep - INFO - source_id=50, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,431 - stpipe.SourceTypeStep - INFO - source_id=51, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,431 - stpipe.SourceTypeStep - INFO - source_id=52, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,432 - stpipe.SourceTypeStep - INFO - source_id=55, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,432 - stpipe.SourceTypeStep - INFO - source_id=65, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,432 - stpipe.SourceTypeStep - INFO - source_id=66, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,433 - stpipe.SourceTypeStep - INFO - source_id=68, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,433 - stpipe.SourceTypeStep - INFO - source_id=56, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,434 - stpipe.SourceTypeStep - INFO - source_id=57, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,434 - stpipe.SourceTypeStep - INFO - source_id=58, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,435 - stpipe.SourceTypeStep - INFO - source_id=59, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,435 - stpipe.SourceTypeStep - INFO - source_id=60, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,436 - stpipe.SourceTypeStep - INFO - source_id=61, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,436 - stpipe.SourceTypeStep - INFO - source_id=62, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,436 - stpipe.SourceTypeStep - INFO - source_id=63, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,437 - stpipe.SourceTypeStep - INFO - source_id=64, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,437 - stpipe.SourceTypeStep - INFO - source_id=67, stellarity=0.0000, type=EXTENDED
2021-03-13 00:12:26,438 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep done
2021-03-13 00:12:26,501 - stpipe.FlatFieldStep - INFO - FlatFieldStep instance created.
2021-03-13 00:12:26,698 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:12:26,700 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_interpolated_flat': False, 'user_supplied_flat': None, 'inverse': False}
2021-03-13 00:12:49,097 - stpipe.FlatFieldStep - INFO - Working on slit 53
2021-03-13 00:12:49,812 - stpipe.FlatFieldStep - INFO - Working on slit 54
2021-03-13 00:12:50,510 - stpipe.FlatFieldStep - INFO - Working on slit 42
2021-03-13 00:12:50,616 - stpipe.FlatFieldStep - INFO - Working on slit 43
2021-03-13 00:12:50,781 - stpipe.FlatFieldStep - INFO - Working on slit 44
2021-03-13 00:12:50,946 - stpipe.FlatFieldStep - INFO - Working on slit 45
2021-03-13 00:12:51,184 - stpipe.FlatFieldStep - INFO - Working on slit 46
2021-03-13 00:12:51,488 - stpipe.FlatFieldStep - INFO - Working on slit 47
2021-03-13 00:12:51,839 - stpipe.FlatFieldStep - INFO - Working on slit 48
2021-03-13 00:12:52,190 - stpipe.FlatFieldStep - INFO - Working on slit 49
2021-03-13 00:12:52,584 - stpipe.FlatFieldStep - INFO - Working on slit 50
2021-03-13 00:12:53,000 - stpipe.FlatFieldStep - INFO - Working on slit 51
2021-03-13 00:12:53,423 - stpipe.FlatFieldStep - INFO - Working on slit 52
2021-03-13 00:12:53,887 - stpipe.FlatFieldStep - INFO - Working on slit 55
2021-03-13 00:12:55,259 - stpipe.FlatFieldStep - INFO - Working on slit 65
2021-03-13 00:12:57,217 - stpipe.FlatFieldStep - INFO - Working on slit 66
2021-03-13 00:12:59,198 - stpipe.FlatFieldStep - INFO - Working on slit 68
2021-03-13 00:13:01,151 - stpipe.FlatFieldStep - INFO - Working on slit 56
2021-03-13 00:13:02,680 - stpipe.FlatFieldStep - INFO - Working on slit 57
2021-03-13 00:13:04,345 - stpipe.FlatFieldStep - INFO - Working on slit 58
2021-03-13 00:13:06,120 - stpipe.FlatFieldStep - INFO - Working on slit 59
2021-03-13 00:13:07,962 - stpipe.FlatFieldStep - INFO - Working on slit 60
2021-03-13 00:13:09,851 - stpipe.FlatFieldStep - INFO - Working on slit 61
2021-03-13 00:13:11,766 - stpipe.FlatFieldStep - INFO - Working on slit 62
2021-03-13 00:13:13,583 - stpipe.FlatFieldStep - INFO - Working on slit 63
2021-03-13 00:13:15,430 - stpipe.FlatFieldStep - INFO - Working on slit 64
2021-03-13 00:13:17,370 - stpipe.FlatFieldStep - INFO - Working on slit 67
2021-03-13 00:13:20,267 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep done
2021-03-13 00:13:20,318 - stpipe.PathLossStep - INFO - PathLossStep instance created.
2021-03-13 00:13:20,783 - stpipe.PathLossStep - INFO - Step PathLossStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:13:20,786 - stpipe.PathLossStep - INFO - Step PathLossStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2021-03-13 00:13:20,844 - stpipe.PathLossStep - INFO - Using PATHLOSS reference file /grp/crds/cache/references/jwst/jwst_nirspec_pathloss_0002.fits
2021-03-13 00:13:20,870 - stpipe.PathLossStep - INFO - Input exposure type is NRS_MSASPEC
2021-03-13 00:13:24,233 - stpipe.PathLossStep - INFO - Working on slit 0
2021-03-13 00:13:24,244 - stpipe.PathLossStep - INFO - Working on slit 1
2021-03-13 00:13:24,255 - stpipe.PathLossStep - INFO - Working on slit 2
2021-03-13 00:13:24,265 - stpipe.PathLossStep - INFO - Working on slit 3
2021-03-13 00:13:24,275 - stpipe.PathLossStep - INFO - Working on slit 4
2021-03-13 00:13:24,285 - stpipe.PathLossStep - INFO - Working on slit 5
2021-03-13 00:13:24,296 - stpipe.PathLossStep - INFO - Working on slit 6
2021-03-13 00:13:24,306 - stpipe.PathLossStep - INFO - Working on slit 7
2021-03-13 00:13:24,316 - stpipe.PathLossStep - INFO - Working on slit 8
2021-03-13 00:13:24,326 - stpipe.PathLossStep - INFO - Working on slit 9
2021-03-13 00:13:24,337 - stpipe.PathLossStep - INFO - Working on slit 10
2021-03-13 00:13:24,347 - stpipe.PathLossStep - INFO - Working on slit 11
2021-03-13 00:13:24,357 - stpipe.PathLossStep - INFO - Working on slit 12
2021-03-13 00:13:24,368 - stpipe.PathLossStep - INFO - Working on slit 13
2021-03-13 00:13:24,379 - stpipe.PathLossStep - INFO - Working on slit 14
2021-03-13 00:13:24,391 - stpipe.PathLossStep - INFO - Working on slit 15
2021-03-13 00:13:24,403 - stpipe.PathLossStep - INFO - Working on slit 16
2021-03-13 00:13:24,414 - stpipe.PathLossStep - INFO - Working on slit 17
2021-03-13 00:13:24,426 - stpipe.PathLossStep - INFO - Working on slit 18
2021-03-13 00:13:24,437 - stpipe.PathLossStep - INFO - Working on slit 19
2021-03-13 00:13:24,448 - stpipe.PathLossStep - INFO - Working on slit 20
2021-03-13 00:13:24,460 - stpipe.PathLossStep - INFO - Working on slit 21
2021-03-13 00:13:24,473 - stpipe.PathLossStep - INFO - Working on slit 22
2021-03-13 00:13:24,484 - stpipe.PathLossStep - INFO - Working on slit 23
2021-03-13 00:13:24,496 - stpipe.PathLossStep - INFO - Working on slit 24
2021-03-13 00:13:24,508 - stpipe.PathLossStep - INFO - Working on slit 25
2021-03-13 00:13:24,521 - stpipe.PathLossStep - INFO - Working on slit 26
2021-03-13 00:13:24,534 - stpipe.PathLossStep - INFO - Step PathLossStep done
2021-03-13 00:13:24,584 - stpipe.BarShadowStep - INFO - BarShadowStep instance created.
2021-03-13 00:13:24,902 - stpipe.BarShadowStep - INFO - Step BarShadowStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2021-03-13 00:13:24,903 - stpipe.BarShadowStep - INFO - Step BarShadowStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2021-03-13 00:13:24,961 - stpipe.BarShadowStep - INFO - Using BARSHADOW reference file /grp/crds/cache/references/jwst/jwst_nirspec_barshadow_0001.fits
2021-03-13 00:13:28,245 - stpipe.BarShadowStep - INFO - Working on slitlet 53
2021-03-13 00:13:28,284 - stpipe.BarShadowStep - INFO - Working on slitlet 54
2021-03-13 00:13:28,323 - stpipe.BarShadowStep - INFO - Working on slitlet 42
2021-03-13 00:13:28,339 - stpipe.BarShadowStep - INFO - Working on slitlet 43
2021-03-13 00:13:28,358 - stpipe.BarShadowStep - INFO - Working on slitlet 44
2021-03-13 00:13:28,377 - stpipe.BarShadowStep - INFO - Working on slitlet 45
2021-03-13 00:13:28,399 - stpipe.BarShadowStep - INFO - Working on slitlet 46
2021-03-13 00:13:28,422 - stpipe.BarShadowStep - INFO - Working on slitlet 47
2021-03-13 00:13:28,449 - stpipe.BarShadowStep - INFO - Working on slitlet 48
2021-03-13 00:13:28,475 - stpipe.BarShadowStep - INFO - Working on slitlet 49
2021-03-13 00:13:28,502 - stpipe.BarShadowStep - INFO - Working on slitlet 50
2021-03-13 00:13:28,531 - stpipe.BarShadowStep - INFO - Working on slitlet 51
2021-03-13 00:13:28,559 - stpipe.BarShadowStep - INFO - Working on slitlet 52
2021-03-13 00:13:28,589 - stpipe.BarShadowStep - INFO - Working on slitlet 55
2021-03-13 00:13:28,652 - stpipe.BarShadowStep - INFO - Working on slitlet 65
2021-03-13 00:13:28,755 - stpipe.BarShadowStep - INFO - Working on slitlet 66
2021-03-13 00:13:28,856 - stpipe.BarShadowStep - INFO - Working on slitlet 68
2021-03-13 00:13:28,963 - stpipe.BarShadowStep - INFO - Working on slitlet 56
2021-03-13 00:13:29,032 - stpipe.BarShadowStep - INFO - Working on slitlet 57
2021-03-13 00:13:29,107 - stpipe.BarShadowStep - INFO - Working on slitlet 58
2021-03-13 00:13:29,187 - stpipe.BarShadowStep - INFO - Working on slitlet 59
2021-03-13 00:13:29,272 - stpipe.BarShadowStep - INFO - Working on slitlet 60
2021-03-13 00:13:29,360 - stpipe.BarShadowStep - INFO - Working on slitlet 61
2021-03-13 00:13:29,451 - stpipe.BarShadowStep - INFO - Working on slitlet 62
2021-03-13 00:13:29,541 - stpipe.BarShadowStep - INFO - Working on slitlet 63
2021-03-13 00:13:29,635 - stpipe.BarShadowStep - INFO - Working on slitlet 64
2021-03-13 00:13:29,730 - stpipe.BarShadowStep - INFO - Working on slitlet 67
2021-03-13 00:13:29,827 - stpipe.BarShadowStep - INFO - Step BarShadowStep done
2021-03-13 00:13:29,893 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:29,894 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(

Looping over open slitlets...
Working with slitlet  53
Slitlet name in fits file previous to barshadow and in barshadow output file are the same.
Calculating barshadow correction...
Reference file used for barshadow calculation: /grp/jwst/wit4/nirspec/CDP3/05_Other_Calibrations/5.3_BarShadow/referenceFilesBS-20160401/jwst-nirspec-mos1x1.bsrf.fits
Calculation of barshadow correction done.
nan nan
Creating final barshadow test plot...

2021-03-13 00:13:32,089 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:32,089 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(

2021-03-13 00:13:32,150 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:32,151 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(

   Relative barshadow_correction  :   mean = -3.195e-03    median = -3.540e-05    stdev = 6.063e-03
    Maximum   Relativebarshadow_correction = 5.761e-04
    Minimum   Relativebarshadow_correction = -2.816e-02
    Percentage of pixels where median of relative differences is greater than: 
                            ->  1xtheshold = 25%
                            ->  3xtheshold = 18%
                            ->  5xtheshold = 13%

 *** WARNING: More than 10% of pixels have a median value greater than 3xthreshold!


 *** WARNING: More than 10% of pixels have a median value greater than 5xthreshold!

 * PASS/FAIL TEST: Is the median <= threshold for slit 53? PASSED

 * Result of number of points greater than 3*threshold greater than 10%: FAILED

 * Result of number of points greater than 5*threshold greater than 10%: FAILED

Working with slitlet  54
Slitlet name in fits file previous to barshadow and in barshadow output file are the same.
Calculating barshadow correction...
Reference file used for barshadow calculation: /grp/jwst/wit4/nirspec/CDP3/05_Other_Calibrations/5.3_BarShadow/referenceFilesBS-20160401/jwst-nirspec-mos1x1.bsrf.fits
Calculation of barshadow correction done.
nan nan
Creating final barshadow test plot...

2021-03-13 00:13:33,877 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:33,878 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(

2021-03-13 00:13:33,938 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:33,939 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(

2021-03-13 00:13:33,940 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/fromnumeric.py:3419: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,

2021-03-13 00:13:33,941 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/numpy/core/_methods.py:180: RuntimeWarning: invalid value encountered in true_divide
  ret = um.true_divide(


# Quickly see if the test passed 

print('These are the final results of the tests: ')
for key, val in results_dict.items():
    print(key, val)

2021-03-13 00:21:02,860 - stpipe - WARNING - /data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.8/site-packages/ipykernel/ipkernel.py:283: DeprecationWarning: `should_run_async` will not call `transform_cell` automatically in the future. Please pass the result to `transformed_cell` argument and any exception that happen during thetransform in `preprocessing_exc_tuple` in IPython 7.17 and above.
  and should_run_async(code)

These are the final results of the tests: 
mos_prism_clear The test is skipped for POINT sources, since the correction is not applied
mos_g140m_f100lp 
 *** Final result for barshadow test will be reported as PASSED ***

JWST Pipeline Validation Testing Notebook: spec2, barshadow step¶

Table of Contents¶

Imports¶

Test Description¶

Results¶

Calibration WG Requested Algorithm:¶

Defining Term¶

Run the JWST pipeline and pathloss validation tests¶

Testing Data Set¶

About this Notebook¶